Skip to main content

Golang XORM搭配OpenTracing+Jaeger链路监控让SQL执行一览无遗（附源码）

系统环境

go version go1.14.3 windows/amd64

⭐ 项目Gitee源码

一、Docker运行JaegerTracing-All-In-One镜像​

Docker命令

docker run -d --name jaeger -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 -p 5775:5775/udp -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 14268:14268 -p 14250:14250 -p 9411:9411 jaegertracing/all-in-one:1.18

浏览器访问localhost:16686，可以看到JaegerUI界面，如下所示： 1.png

至此，以内存作为数据寄存方式的OpenTracing+Jaeger服务成功运行。

二、GoModule安装Xorm、OpenTracing和Jaeger​

Xorm - 需要 1.0 版本及以上才能支持传递Context上下文

go get xorm.io/xorm

OpenTracing和Jaeger - 只需要安装Jaeger-Client就会依赖Opentracing

go get github.com/uber/jaeger-client-go

三、初始化Opentracing和Jaeger​

func initJaeger() (closer io.Closer, err error) {
    // 根据配置初始化Tracer 返回Closer
    tracer, closer, err := (&config.Configuration{
        ServiceName: "xormWithTracing",
        Disabled:    false,
        Sampler: &config.SamplerConfig{
            Type: jaeger.SamplerTypeConst,
            // param的值在0到1之间，设置为1则将所有的Operation输出到Reporter
            Param: 1,
        },
        Reporter: &config.ReporterConfig{
            LogSpans:           true,
            LocalAgentHostPort: "localhost:6831",
        },
    }).NewTracer()
    if err != nil {
        return
    }

    // 设置全局Tracer - 如果不设置将会导致上下文无法生成正确的Span
    opentracing.SetGlobalTracer(tracer)
    return
}

单元测试结果2.png

四、通过日志模块将链路监控侵入到XORM执行逻辑中​

  1. XORM通过其中Log包里面的ContextLogger接口定义了它需要的日志实例是怎么样的，我们可以在外部实现该接口就可以将链路监控的逻辑侵入到XORM的执行过程
// xorm.io\\xorm@v1.0.2\\log
// ContextLogger represents a logger interface with context
type ContextLogger interface {
    SQLLogger

    Debugf(format string, v ...interface{})
    Errorf(format string, v ...interface{})
    Infof(format string, v ...interface{})
    Warnf(format string, v ...interface{})

    Level() LogLevel
    SetLevel(l LogLevel)

    ShowSQL(show ...bool)
    IsShowSQL() bool
}

  1. 实现接口的代码比较长，这里只截取重要部分，如果有需要可以到源码中查看
// ---\> 请注意import
// 因为我们需要多个名为Log的包
// 所以我们需要手动重命名
import (
    "fmt"
    \_ "github.com/go-sql-driver/mysql"
    "github.com/opentracing/opentracing-go"
    tracerLog "github.com/opentracing/opentracing-go/log"
    "github.com/uber/jaeger-client-go"
    "github.com/uber/jaeger-client-go/config"
    "github.com/uber/jaeger-client-go/log/zap"
    zap2 "go.uber.org/zap"
    "io"
    "xorm.io/xorm"
    xormLog "xorm.io/xorm/log"
)

type CustomCtxLogger struct {
    logger  \*zap.Logger
    level   xormLog.LogLevel
    showSQL bool

    // ---\> 这里span是从上下文中创建的
    // 我们不能将创建的span写回到上下文
    // 所以只能在Logger中维护一个span
    span    opentracing.Span
}

// BeforeSQL implements ContextLogger
func (l \*CustomCtxLogger) BeforeSQL(ctx xormLog.LogContext) {
    // ----\> 重头戏在这里，需要从Context上下文中创建一个新的Span来对SQL执行进行链路监控
    l.span, \_ = opentracing.StartSpanFromContext(ctx.Ctx, "XORM SQL Execute")
}

// AfterSQL implements ContextLogger
func (l \*CustomCtxLogger) AfterSQL(ctx xormLog.LogContext) {
    // defer结束掉span
    defer l.span.Finish()

    // 原本的SimpleLogger里面会获取一次SessionId
    var sessionPart string
    v := ctx.Ctx.Value("\_\_xorm\_session\_id")
    if key, ok := v.(string); ok {
        sessionPart = fmt.Sprintf(" [%s]", key)
        l.span.LogFields(tracerLog.String("session\_id", sessionPart))
    }

    // 将Ctx中全部的信息写入到Span中
    l.span.LogFields(tracerLog.String("SQL", ctx.SQL))
    l.span.LogFields(tracerLog.Object("args", ctx.Args))
    l.span.SetTag("execute\_time", ctx.ExecuteTime)

    if ctx.ExecuteTime \> 0 {
        l.logger.Infof("[SQL]%s %s %v - %v", sessionPart, ctx.SQL, ctx.Args, ctx.ExecuteTime)
    } else {
        l.logger.Infof("[SQL]%s %s %v", sessionPart, ctx.SQL, ctx.Args)
    }
}

// 下面还有一些比较简单的接口实现，有兴趣的可以看源码

  1. 重写XORM引擎创建方法
func NewEngine() (engine \*xorm.Engine, err error) {
 // XORM创建引擎
 engine, err = xorm.NewEngine("mysql", "test:test@/test?charset=utf8mb4")
 if err != nil {
     return
 }

 // 创建自定义的日志实例
 _l, err := zap2.NewDevelopment()
 if err != nil {
     return
 }

 // 将日志实例设置到XORM的引擎中
 engine.SetLogger(&CustomCtxLogger{
     logger:  zap.NewLogger(_l),
     level:   xormLog.LOG_DEBUG,
     showSQL: true,
     span:    nil,
 })
 return
}

六、单元测试​

单元测试代码

// XORM技术文档范例
type User struct {
    Id   int64
    Name string `xorm:"varchar(25) notnull unique 'usr\_name' comment('姓名')"`
}

func TestNewEngine(t \*testing.T) {
    // 初始化XORM引擎
    engine, err := NewEngine()
    if err != nil {
        t.Fatal(err)
    }

    // 初始化Tracer
    closer, err := initJaeger()
    if err != nil {
        t.Fatal(err)
    }
    defer closer.Close()

    // 生成新的Span - 注意将span结束掉，不然无法发送对应的结果
    span := opentracing.StartSpan("xorm sync")
    defer span.Finish()

    // 把生成的Root Span写入到Context上下文，获取一个子Context
    ctx := opentracing.ContextWithSpan(context.Background(), span)

    // 将子上下文传入Session
    session := engine.Context(ctx)

    // Sync2同步表结构
    if err := session.Sync2(&User{}); err != nil {
        t.Fatal(err)
    }

    // 插入一条数据
    if \_, err := session.InsertOne(&User{Name: "test"}); err != nil {
        t.Fatal()
    }
}

最终执行结果如下

2020-06-15T23:49:12.888+0800    INFO    zap/logger.go:38    [SQL] SELECT `TABLE_NAME`, `ENGINE`, `AUTO_INCREMENT`, `TABLE_COMMENT` from `INFORMATION_SCHEMA`.`TABLES` WHERE `TABLE_SCHEMA`=? AND (`ENGINE`='MyISAM' OR `ENGINE` = 'InnoDB' OR `ENGINE` = 'TokuDB') [test] - 7.0021ms
2020-06-15T23:49:13.633+0800    INFO    zap/logger.go:38    [SQL] CREATE TABLE IF NOT EXISTS `user` (`id` BIGINT(20) PRIMARY KEY AUTO_INCREMENT NOT NULL, `usr_name` VARCHAR(25) NOT NULL COMMENT '姓名') DEFAULT CHARSET utf8mb4 [] -   730.5132ms
2020-06-15T23:49:14.252+0800    INFO    zap/logger.go:38    [SQL] CREATE UNIQUE INDEX `UQE_user_usr_name` ON `user` (`usr_name`) [] - 619.0328ms
2020-06-15T23:49:14.367+0800    INFO    zap/logger.go:38    [SQL] INSERT INTO `user` (`usr_name`) VALUES (?) [test] - 115.1608ms

使用JaegerUI查看链路追踪的结果，可以清晰的看到每一条SQL语句执行的顺序、时间、内容、参数以及在整个Session所占的比例，有效提高我们在企业项目中分析项目的短板

3.png